<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd">
<html xmlns="http://www.w3.org/1999/xhtml">
<head>
  <meta http-equiv="Content-Type" content="text/html; charset=utf-8" />
  <meta http-equiv="Content-Style-Type" content="text/css" />
  <meta name="generator" content="pandoc" />
  <title>nfsv3 lockd和write的重传定时器对比</title>
  <style type="text/css">code{white-space: pre;}</style>
  <style type="text/css">
div.sourceCode { overflow-x: auto; }
table.sourceCode, tr.sourceCode, td.lineNumbers, td.sourceCode {
  margin: 0; padding: 0; vertical-align: baseline; border: none; }
table.sourceCode { width: 100%; line-height: 100%; }
td.lineNumbers { text-align: right; padding-right: 4px; padding-left: 4px; color: #aaaaaa; border-right: 1px solid #aaaaaa; }
td.sourceCode { padding-left: 5px; }
code > span.kw { color: #007020; font-weight: bold; } /* Keyword */
code > span.dt { color: #902000; } /* DataType */
code > span.dv { color: #40a070; } /* DecVal */
code > span.bn { color: #40a070; } /* BaseN */
code > span.fl { color: #40a070; } /* Float */
code > span.ch { color: #4070a0; } /* Char */
code > span.st { color: #4070a0; } /* String */
code > span.co { color: #60a0b0; font-style: italic; } /* Comment */
code > span.ot { color: #007020; } /* Other */
code > span.al { color: #ff0000; font-weight: bold; } /* Alert */
code > span.fu { color: #06287e; } /* Function */
code > span.er { color: #ff0000; font-weight: bold; } /* Error */
code > span.wa { color: #60a0b0; font-weight: bold; font-style: italic; } /* Warning */
code > span.cn { color: #880000; } /* Constant */
code > span.sc { color: #4070a0; } /* SpecialChar */
code > span.vs { color: #4070a0; } /* VerbatimString */
code > span.ss { color: #bb6688; } /* SpecialString */
code > span.im { } /* Import */
code > span.va { color: #19177c; } /* Variable */
code > span.cf { color: #007020; font-weight: bold; } /* ControlFlow */
code > span.op { color: #666666; } /* Operator */
code > span.bu { } /* BuiltIn */
code > span.ex { } /* Extension */
code > span.pp { color: #bc7a00; } /* Preprocessor */
code > span.at { color: #7d9029; } /* Attribute */
code > span.do { color: #ba2121; font-style: italic; } /* Documentation */
code > span.an { color: #60a0b0; font-weight: bold; font-style: italic; } /* Annotation */
code > span.cv { color: #60a0b0; font-weight: bold; font-style: italic; } /* CommentVar */
code > span.in { color: #60a0b0; font-weight: bold; font-style: italic; } /* Information */
  </style>
  <link rel="stylesheet" href="doc/linux-style.css" type="text/css" />
</head>
<body>
<div id="header">
<h1 class="title">nfsv3 lockd和write的重传定时器对比</h1>
</div>
<div id="TOC">
<ul>
<li><a href="#nfsv3-lockd和write的重传定时器对比">nfsv3 lockd和write的重传定时器对比</a><ul>
<li><a href="#内核改造">内核改造：</a></li>
</ul></li>
</ul>
</div>
<h1 id="nfsv3-lockd和write的重传定时器对比">nfsv3 lockd和write的重传定时器对比</h1>
<h2 id="内核改造">内核改造：</h2>
<p><a href="https://chenxiaosong.com/course/nfs/issue/lockd-server-not-responding.html">具体内核修改代码点此链接</a></p>
<p>nfsv3 NLM请求超时的问题测试结果:</p>
<div class="sourceCode"><pre class="sourceCode sh"><code class="sourceCode bash"><span class="bu">[</span>   74.865468] RPC:    56 setting alarm for 10000 ms
[   85.116887] RPC:    56 setting alarm for 20000 ms
[  105.599780] RPC:    56 setting alarm for 30000 ms
[  135.796650] RPC:    56 setting alarm for 60000 ms
[  135.938420] RPC:    56 setting alarm for 10000 ms
[  146.050487] RPC:    56 setting alarm for 20000 ms</code></pre></div>
<p>nfsv3 wirte请求超时问题测试结果:</p>
<div class="sourceCode"><pre class="sourceCode sh"><code class="sourceCode bash"><span class="bu">[</span>   96.740830] RPC:    48 setting alarm for 60000 ms
[  156.800261] RPC:    48 setting alarm for 120000 ms
[  279.680731] RPC:    48 setting alarm for 180000 ms
[  459.904366] RPC:    48 setting alarm for 60000 ms
[  521.354910] RPC:    48 setting alarm for 120000 ms</code></pre></div>
<p>可以看到lockd操作的重传时间是每次增加10000ms 而write则是每次都在基础时间加上timeout</p>
<p>修改一下内核代码，查看为什么会这样。</p>
<div class="sourceCode"><pre class="sourceCode diff"><code class="sourceCode diff"> diff --git a/net/sunrpc/xprt.c b/net/sunrpc/xprt.c
index b1abf4848bbc..74cd024b0139 100644
<span class="kw">--- a/net/sunrpc/xprt.c</span>
<span class="dt">+++ b/net/sunrpc/xprt.c</span>
<span class="dt">@@ -617,11 +617,20 @@ int xprt_adjust_timeout(struct rpc_rqst *req)</span>
        const struct rpc_timeout *to = req-&gt;rq_task-&gt;tk_client-&gt;cl_timeout;
        int status = 0;
 
<span class="va">+</span>
        if (time_before(jiffies, req-&gt;rq_majortimeo)) {
                if (to-&gt;to_exponential)
<span class="va">+               {</span>
<span class="va">+                       printk(&quot;PID: %d  xprt_adjust_timeout_expon timeout_before = %ld\n&quot;,current-&gt;pid,req-&gt;rq_timeout);</span>
                        req-&gt;rq_timeout &lt;&lt;= 1;
<span class="va">+                       printk(&quot;PID: %d  xprt_adjust_timeout_expon timeout_after = %ld\n&quot;,current-&gt;pid,req-&gt;rq_timeout);</span>
<span class="va">+               }</span>
                else
<span class="va">+               {</span>
<span class="va">+                       printk(&quot;PID: %d  xprt_adjust_timeout timeout_before = %ld increment = %ld\n&quot;,current-&gt;pid,req-&gt;rq_timeout,to-&gt;to_increment);</span>
                        req-&gt;rq_timeout += to-&gt;to_increment;
<span class="va">+                       printk(&quot;PID: %d  xprt_adjust_timeout_noexpon timeout_after = %ld\n&quot;,current-&gt;pid,req-&gt;rq_timeout);</span>
<span class="va">+               }</span>
                if (to-&gt;to_maxval &amp;&amp; req-&gt;rq_timeout &gt;= to-&gt;to_maxval)
                        req-&gt;rq_timeout = to-&gt;to_maxval;
                req-&gt;rq_retries++;</code></pre></div>
<p>先测试一下lockd打印一下值看一下：</p>
<div class="sourceCode"><pre class="sourceCode sh"><code class="sourceCode bash"><span class="bu">[</span>  173.820271] RPC:    45 setting alarm for 60000 ms
[  173.847847] RPC:    46 setting alarm for 60000 ms
[  174.045381] RPC:    47 setting alarm for 60000 ms
[  174.152906] RPC:    48 setting alarm for 60000 ms
[  174.189646] RPC:    49 setting alarm for 60000 ms
[  174.277126] RPC:    49 setting alarm for 60000 ms
[  174.321568] RPC:    48 setting alarm for 10000 ms
[  174.450915] RPC:    50 setting alarm for 60000 ms
[  174.492788] RPC:    51 setting alarm for 60000 ms
[  174.577074] RPC:    51 setting alarm for 60000 ms
[  174.624928] RPC:    50 setting alarm for 60000 ms
[  174.644539] RPC:    50 setting alarm for 60000 ms
[  174.826054] RPC:    52 setting alarm for 10000 ms
[  184.971505] RPC:    52 setting alarm for 20000 ms
[  205.446885] RPC:    52 setting alarm for 30000 ms
[  235.641735] RPC:    52 setting alarm for 60000 ms
[  235.697804] RPC:    53 setting alarm for 60000 ms
[  235.759510] RPC:    53 setting alarm for 60000 ms
[  235.833243] RPC:    52 setting alarm for 10000 ms
[  245.898263] RPC:    52 setting alarm for 20000 ms
[  266.375841] RPC:    52 setting alarm for 30000 ms
[  296.565926] RPC:    52 setting alarm for 60000 ms
[  296.618845] RPC:    54 setting alarm for 60000 ms
[  296.689948] RPC:    54 setting alarm for 60000 ms
[  296.768341] RPC:    52 setting alarm for 10000 ms

<span class="co">#以52为例子</span>
[  174.826054] RPC:    52 setting alarm for 10000 ms   # 第一次
[  184.971505] RPC:    52 setting alarm for 20000 ms   # 第二次
[  205.446885] RPC:    52 setting alarm for 30000 ms   # 第三次
[  235.641735] RPC:    52 setting alarm for 60000 ms   # 第四次
[  235.833243] RPC:    52 setting alarm for 10000 ms   # 又回到初始
[  245.898263] RPC:    52 setting alarm for 20000 ms
[  266.375841] RPC:    52 setting alarm for 30000 ms
[  296.565926] RPC:    52 setting alarm for 60000 ms
[  296.768341] RPC:    52 setting alarm for 10000 ms

[  174.209316] PID: 7  xprt_adjust_timeout timeout_before <span class="ot">=</span> 60000 increment <span class="ot">=</span> 0  
[  174.209317] PID: 7  xprt_adjust_timeout_noexpon timeout_after <span class="ot">=</span> 60000
[  174.326249] PID: 543  xprt_adjust_timeout timeout_before <span class="ot">=</span> 10000 increment <span class="ot">=</span> 10000  #可以看到每次的情况都是初始赋值就已经决定每次重传送时间增加的时间了。
[  174.326250] PID: 543  xprt_adjust_timeout_noexpon timeout_after <span class="ot">=</span> 20000
[  174.511857] PID: 7  xprt_adjust_timeout timeout_before <span class="ot">=</span> 60000 increment <span class="ot">=</span> 0
[  174.511858] PID: 7  xprt_adjust_timeout_noexpon timeout_after <span class="ot">=</span> 60000
[  174.631486] PID: 543  xprt_adjust_timeout timeout_before <span class="ot">=</span> 60000 increment <span class="ot">=</span> 0
[  174.631486] PID: 543  xprt_adjust_timeout_noexpon timeout_after <span class="ot">=</span> 60000
[  184.940567] PID: 543  xprt_adjust_timeout timeout_before <span class="ot">=</span> 10000 increment <span class="ot">=</span> 10000
[  184.943163] PID: 543  xprt_adjust_timeout_noexpon timeout_after <span class="ot">=</span> 20000
[  205.416110] PID: 543  xprt_adjust_timeout timeout_before <span class="ot">=</span> 20000 increment <span class="ot">=</span> 10000
[  205.418692] PID: 543  xprt_adjust_timeout_noexpon timeout_after <span class="ot">=</span> 30000
[  235.717880] PID: 179  xprt_adjust_timeout timeout_before <span class="ot">=</span> 60000 increment <span class="ot">=</span> 0
[  235.717883] PID: 179  xprt_adjust_timeout_noexpon timeout_after <span class="ot">=</span> 60000
[  245.867901] PID: 543  xprt_adjust_timeout timeout_before <span class="ot">=</span> 10000 increment <span class="ot">=</span> 10000
[  245.870501] PID: 543  xprt_adjust_timeout_noexpon timeout_after <span class="ot">=</span> 20000
[  266.347213] PID: 543  xprt_adjust_timeout timeout_before <span class="ot">=</span> 20000 increment <span class="ot">=</span> 10000
[  266.349671] PID: 543  xprt_adjust_timeout_noexpon timeout_after <span class="ot">=</span> 30000
[  296.638350] PID: 485  xprt_adjust_timeout timeout_before <span class="ot">=</span> 60000 increment <span class="ot">=</span> 0
[  296.638351] PID: 485  xprt_adjust_timeout_noexpon timeout_after <span class="ot">=</span> 60000</code></pre></div>
<p>再测试wite看一下</p>
<div class="sourceCode"><pre class="sourceCode sh"><code class="sourceCode bash"><span class="bu">[</span>   60.751322] PID: 542  xprt_adjust_timeout timeout_before <span class="ot">=</span> 60000 increment <span class="ot">=</span> 0
[   60.753885] PID: 542  xprt_adjust_timeout_noexpon timeout_after <span class="ot">=</span> 60000
[   60.763116] PID: 542  xprt_adjust_timeout timeout_before <span class="ot">=</span> 60000 increment <span class="ot">=</span> 60000
[   60.765747] PID: 542  xprt_adjust_timeout_noexpon timeout_after <span class="ot">=</span> 120000 <span class="co">#write这里是按照nfs挂载参数来初始化增量参数的</span></code></pre></div>
<p>照这么来看，好像这两个函数调用的都是线性增长？ 只不过是timout的初始值，和increment赋值不一样。</p>
<p>所以找一下lockd这两个值初始化是在那里设置的吧？</p>
<p>在 fs/lockd/clntproc.c 的 nlmclnt_init() 中初始化</p>
<div class="sourceCode"><pre class="sourceCode c"><code class="sourceCode c">nlmclnt_init
    nlmclnt_lookup_host
        nlm_bind_host
            rpc_create
                rpc_create_args
                    .timeout    = &amp;timeparms,
                        .to_initval = increment,
                        .to_increment   = increment,
                        .to_maxval  = increment * 6UL,
                            <span class="dt">unsigned</span> <span class="dt">long</span> increment = nlmsvc_timeout;
                                nlmsvc_timeout = nlm_timeout * HZ;
                                    <span class="dt">static</span> <span class="dt">unsigned</span> <span class="dt">long</span>        nlm_timeout = LOCKD_DFLT_TIMEO;
                                        <span class="pp">#define LOCKD_DFLT_TIMEO    10</span></code></pre></div>
<p>这里的代码说明了,在其nlm请求的时候，nlm的timout初始值和增加的值默认是等于10的</p>
<p>另外一个问题，好像并不是所有有的setting alram for 都是按照线性增加的，有一些rpc任务是重传一两次就结束了。</p>
<p>可以去看一下这重传一两次的请求是不是lockd请求？</p>
<p>在内核代码中修改：</p>
<div class="sourceCode"><pre class="sourceCode diff"><code class="sourceCode diff"><span class="kw">diff --git a/net/sunrpc/sched.c b/net/sunrpc/sched.c</span>
index 92d88aa62085..16de9a96997b 100644
<span class="dt">--- a/net/sunrpc/sched.c</span>
+++ b/net/sunrpc/sched.c
@@ -93,6 +93,13 @@ __rpc_add_timer(struct rpc_wait_queue *queue, struct rpc_task *task)
        dprintk(&quot;RPC: %5u setting alarm for %u ms\n&quot;,
                task-&gt;tk_pid, jiffies_to_msecs(task-&gt;tk_timeout));
 
+
+       //判断NLM请求类型 
+    const char *progname = (task-&gt;tk_client &amp;&amp; task-&gt;tk_client-&gt;cl_program) ? task-&gt;tk_client-&gt;cl_program-&gt;name : &quot;NULL&quot;;
+    const char *procname = (task-&gt;tk_msg.rpc_proc) ? task-&gt;tk_msg.rpc_proc-&gt;p_name : &quot;NULL&quot;;
+    printk(&quot;RPC: %5u, client=%s, proc=%s, timeout=%u ms\n&quot;,
+        task-&gt;tk_pid,progname, procname,jiffies_to_msecs(task-&gt;tk_timeout));
+
        task-&gt;u.tk_wait.expires = jiffies + task-&gt;tk_timeout;
        if (list_empty(&amp;queue-&gt;timer_list.list) || time_before(task-&gt;u.tk_wait.expires, queue-&gt;timer_list.expires))
                rpc_set_queue_timer(queue, task-&gt;u.tk_wait.expires);</code></pre></div>
<div class="sourceCode"><pre class="sourceCode sh"><code class="sourceCode bash"><span class="bu">[</span>  371.270194] RPC:    45, client=nfs, proc=GETATTR, timeout=60000 ms
[  371.387614] RPC:    46, client=nfs, proc=GETATTR, timeout=60000 ms
[  371.479991] RPC:    47, client=nfs, proc=ACCESS, timeout=60000 ms
[  371.509836] RPC:    48, client=lockd, proc=TEST, timeout=60000 ms
[  371.510276] RPC:    48, client=lockd, proc=TEST, timeout=10000 ms
[  371.510349] RPC:    48, client=lockd, proc=TEST, timeout=20000 ms
[  371.509912] RPC:    49, client=rpcbind, proc=GETPORT, timeout=60000 ms
[  371.510045] RPC:    49, client=rpcbind, proc=GETPORT, timeout=60000 ms

[  371.270193] RPC:    45 setting alarm for 60000 ms
[  371.387613] RPC:    46 setting alarm for 60000 ms
[  371.479991] RPC:    47 setting alarm for 60000 ms
[  371.509835] RPC:    48 setting alarm for 60000 ms
[  371.510274] RPC:    48 setting alarm for 10000 ms
[  371.510349] RPC:    48 setting alarm for 20000 ms
[  371.509911] RPC:    49 setting alarm for 60000 ms
[  371.510044] RPC:    49 setting alarm for 60000 ms</code></pre></div>
<p>可以看到当我的client=lockd则是NLM请求，proc名称则是TEST也与NLM请求相关，这样就揭示了为什么从日志信息来看会有不同从初始时间。</p>
<p>是否会造成5s这样的倍数？ 这里有一个5的倍数代码：</p>
<p>get_lockd_grace_period return nlm_timeout * 5 * HZ;</p>
<p>在这个代码里面增加打印</p>
<div class="sourceCode"><pre class="sourceCode diff"><code class="sourceCode diff"><span class="kw">diff --git a/fs/lockd/svc.c b/fs/lockd/svc.c</span>
index 346ed161756d..acb013fc39f3 100644
<span class="dt">--- a/fs/lockd/svc.c</span>
+++ b/fs/lockd/svc.c
@@ -88,11 +88,19 @@ static struct ctl_table_header * nlm_sysctl_table;
 
 static unsigned long get_lockd_grace_period(void)
 {
+       /* 打印调用栈 */
+    dump_stack();
        /* Note: nlm_timeout should always be nonzero */
        if (nlm_grace_period)
+       {
+               printk(&quot;get_lockd_grace_period = %ld&quot;,roundup(nlm_grace_period, nlm_timeout));
                return roundup(nlm_grace_period, nlm_timeout) * HZ;
+       }
        else
+       {
+               printk(&quot;get_lockd_grace_period nlm_timeout = %ld&quot;,nlm_timeout * 5 * HZ);
                return nlm_timeout * 5 * HZ;
+       }
 }</code></pre></div>
<p>打印到日志查看一下这个值的内容: [ 266.981120] get_lockd_grace_period nlm_timeout = 50000</p>
<p>确实调用了,但只是调用了一次</p>
<p>这个函数是计算 NFS 锁管理服务的客户端恢复崩溃后重新声明锁的时间窗口 从日志信息来看而且这个函数是会发生在nlmsvc_lock之前</p>
<p>这个函数的调用栈:</p>
<div class="sourceCode"><pre class="sourceCode sh"><code class="sourceCode bash"><span class="ex">vfs_write</span>
    <span class="ex">__vfs_write</span>
        <span class="ex">nfsd_svc</span>
            <span class="ex">nfsd_startup_net</span>
                <span class="ex">lockd_up.cold</span>
                    <span class="ex">set_grace_period</span>
                        <span class="ex">get_lockd_grace_period</span></code></pre></div>
</body>
</html>
